﻿/************************************************************************
* AIDE - Automata Identification Engine
* Copyright (C) 2012-2013 Ali Khalili (khalili_DOT_ir_@SIGN_gmail_DOT_com)
* **********************************************************************
* This program is free software; you can redistribute it and/or modify it
* under the terms of the GNU Lesser General Public License (LGPL) published
* by the Free Software Foundation; either version 2.1 of the License, or (at your
* option) any later version. This program is distributed without any
* warranty. See the GNU Lesser General Public License for more details.
* ***********************************************************************
* File         :     AIDE\Base\LearningLog.cs
* Description  :     Facilitate logging in the tool
* Change log   :     -1  May 2013:  Initial Development
*                    -23 Aug 2013: Adding  stream writer (so you can write the log inside of the program)
*                    -31 Aug 2013: Adding a timer
* To Do        :     -Log output as TXT, XML and HTML
*                    -Log level
************************************************************************/

using System;
using System.Collections.Generic;
using System.IO;
using System.Text;

namespace AIDE.Base
{
	/// <summary>
	/// To store some statistical logs
	/// <remarks>Note that at most, one instance of -any kind of- learner should be executing at any time</remarks>
	/// </summary>
	public class LearningLog
	{
		static bool keepLogOfEvents;
		//static List<ActionRecord> logOfEvents;

		/// <summary>
		/// Set logging level
		/// <remarks>
		/// <para>Option=1: </para>
		/// </remarks>
		/// </summary>
		/// <param name="l">the logging level</param>
		public void SetLevel(int l)
		{
			level = l;
		}

		/// <summary>
		/// Initialize the logger
		/// </summary>
		public static void InitLogger()
		{
			myEvents = new Dictionary<string, ActionRecord>();

			keepLogOfEvents = false;
			level = 1;
			//logOfEvents = new List<ActionRecord>();
			initialized = true;
			numberOfMQ = 0;
			numberOfEQ = 0;
			numberOfResets = 0;
			numberOfSULSteps = 0;
			numberOfResetsForEq = 0;
			numberOfRealResets = 0;

			eventsLog = new StringBuilder();
			myEvents = new Dictionary<string, ActionRecord>();
			myValues = new Dictionary<string, ValueRecord>();

			timers = new List<KeyValuePair<string, DateTime> >();

			eqTimeSpan = mqTimeSpan = rTimeSpan = qOnSULTimeSpan = totalTimeSpan = TimeSpan.Zero;
			eqStarted = mqStarted = rStarted = qOnSULStarted = totalStarted = false;
		}

		/// <summary>
		/// Clear all statistics and numbers [to start a new learning]
		/// <remarks>
		/// After each learning, call "LogOfEvents" and then, call this function to reset values
		/// for the next round of learning
		/// </remarks>
		/// </summary>
		public static void ClearStats()
		{
			keepLogOfEvents = false;
			level = 1;
			numberOfMQ = 0;
			numberOfEQ = 0;
			numberOfResets = 0;
			numberOfSULSteps = 0;
			numberOfRealResets = 0;
			eqTimeSpan = mqTimeSpan = rTimeSpan = qOnSULTimeSpan = totalTimeSpan = TimeSpan.Zero;
			eqStarted = mqStarted = rStarted = qOnSULStarted = totalStarted = false;
		}

		#region =-[ TIMER ]=-

		/// <summary>
		/// Start the timer
		/// <param name="timerName">Name of timer</param>
		/// </summary>
		public static void StartTimer(string timerName)
		{
			KeyValuePair<string, DateTime> nTimer =
			        new KeyValuePair<string, DateTime>(timerName, DateTime.Now);
			timers.Add(nTimer);
		}

		/// <summary>
		/// Stop the timer (and return the time interval)
		/// </summary>
		/// <returns>the time interval</returns>
		public static TimeSpan StopTimer(string timerName)
		{
			TimeSpan ts = TimeSpan.Zero;
			for (int i = 0; i < timers.Count; i++)
			{
				if (timers[i].Key == timerName)
				{
					KeyValuePair<string, DateTime> nTimer = timers[i];
					timers.RemoveAt(i);
					ts += (DateTime.Now - nTimer.Value);
				}
			}
			return ts;
		}

		static List<KeyValuePair<string, DateTime> > timers;

		#endregion


		#region =-[ UNKNOWN ACTIONS ]=-
		static Dictionary<string, ActionRecord> myEvents;
		static Dictionary<string, ValueRecord> myValues;

		/// <summary>
		/// Record of values
		/// </summary>
		class ValueRecord
		{
			string ID;
			object value;

			public ValueRecord(string ID, object value)
			{
				this.ID = ID;
				this.value = value;
			}

			public object Value
			{
				get
				{
					return this.value;
				}
				set
				{
					this.value = value;
				}
			}

			public string IDent
			{
				get
				{
					return this.ID;
				}
			}

			public override string ToString()
			{
				return ID + " = " + value.ToString();
			}
		}

		/// <summary>
		/// Record of actions
		/// </summary>
		class ActionRecord
		{

			string name;
			bool started;
			DateTime lastCall;
			TimeSpan totalTime;
			int NumberOfTime;
			bool isImmediate;

			/// <summary>
			/// Constructor
			/// </summary>
			/// <param name="name">ID of event</param>
			/// <param name="isImmediate">true if the action is immediate, false in other case</param>
			public ActionRecord(string name, bool isImmediate = false)
			{
				this.name = name;
				this.isImmediate = isImmediate;
			}

			/// <summary>
			/// Reset statistics related to this action
			/// </summary>
			public void Reset()
			{
				this.started = false;
				this.totalTime = TimeSpan.Zero;
				this.NumberOfTime = 0;
			}

			/// <summary>
			/// ID of the action
			/// </summary>
			public string ID
			{
				get
				{
					return name;
				}
			}

			/// <summary>
			/// Count this -immediate- event (one time)
			/// </summary>
			public void Count()
			{
				if (isImmediate)
					NumberOfTime++;
				else
					throw new Exception("The type of action is not immediate (it should be started and finished in separate times!");
			}

			/// <summary>
			/// Start this action
			/// </summary>
			public void Start()
			{
				if (isImmediate)
					throw new Exception("The type of action is immediate (it should be counted!");
				if (this.started)
					throw new Exception("The action is already started!");
				NumberOfTime++;
				this.started = true;
				this.lastCall = DateTime.Now;
			}

			/// <summary>
			/// Finish this action
			/// </summary>
			public void Finish()
			{
				if (!this.started)
					throw new Exception("The action is already started!");
				this.started = false;
				this.totalTime += (DateTime.Now - lastCall);
			}

			/// <summary>
			/// Total time spent on this event
			/// </summary>
			public double TotalTime
			{
				get
				{
					return this.totalTime.TotalMilliseconds;
				}
			}

			/// <summary>
			/// Total number of execution for this event
			/// </summary>
			public int TotalNumberOfExec
			{
				get
				{
					return this.NumberOfTime;
				}
			}


			public override string ToString()
			{
				string s = " Action (" + name + "): ";
				if (this.isImmediate)
				{
					s += " [Number of execution: " + TotalNumberOfExec + "]";
				}
				else
				{
					s += " [Number of execution: " + TotalNumberOfExec + " Time of execution: " + TotalTime + "]";
				}
				return s;
			}
		}

		/// <summary>
		/// Time spent on a -non immediate-action
		/// </summary>
		/// <param name="eventName">name of action</param>
		/// <returns>Time spent on an action (in millisecond), -1 if the action is not defined</returns>
		public static double TimeSpentOnAction(string eventName)
		{
			ActionRecord myRec;
			myEvents.TryGetValue(eventName, out myRec);
			if (myRec != null)
			{
				return myRec.TotalTime;
			}
			return -1;
		}

		/// <summary>
		/// Total number of execution for a specific event
		/// </summary>
		/// <param name="eventName">name of event</param>
		/// <returns>number of execution of an event, -1 if the event is not defined</returns>
		public static int NumberOfExecutionsof(string eventName)
		{
			ActionRecord myRec;
			myEvents.TryGetValue(eventName, out myRec);
			if (myRec != null)
			{
				return myRec.TotalNumberOfExec;
			}
			return -1;
		}


		/// <summary>
		/// Clear info's about one action
		/// </summary>
		/// <param name="eventName"></param>
		public static void ResetAction(string eventName)
		{
			ActionRecord myRec;
			myEvents.TryGetValue(eventName, out myRec);
			if (myRec != null)
			{
				myRec.Reset();
			}
		}

		/// <summary>
		/// Count actions/events that are instantanios (immediate).
		/// </summary>
		/// <param name="eventName"></param>
		public static void CountAction(string eventName)
		{
			ActionRecord myRec;
			myEvents.TryGetValue(eventName, out myRec);
			if (myRec == null)
			{
				myRec = new ActionRecord(eventName, true);
				myEvents.Add(eventName, myRec);
				myRec.Count();
			}
			else
				myRec.Count();

			if (keepLogOfEvents)
			{

			}
		}

		/// <summary>
		/// Start one action
		/// </summary>
		/// <param name="eventName">name of action</param>
		public static void StartAction(string eventName)
		{
			ActionRecord myRec;
			myEvents.TryGetValue(eventName, out myRec);
			if (myRec == null)
			{
				myRec = new ActionRecord(eventName, false);
				myEvents.Add(eventName, myRec);
				myRec.Start();
			}
			else
				myRec.Start();

			if (keepLogOfEvents)
			{

			}
		}

		/// <summary>
		/// Finish the action (it should be already started)
		/// </summary>
		/// <param name="eventName">name of action</param>
		public static void FinishAction(string eventName)
		{
			ActionRecord myRec;
			myEvents.TryGetValue(eventName, out myRec);
			if (myRec == null)
			{
				throw new Exception("This action doesn't exist!");
			}
			else
				myRec.Finish();

			if (keepLogOfEvents)
			{

			}
		}


		/// <summary>
		/// Set a variable
		/// </summary>
		/// <param name="valueID">name of variable</param>
		/// <param name="value">value of variable</param>
		public static void SetAValue(string valueID, object value)
		{
			ValueRecord myRec;
			myValues.TryGetValue(valueID, out myRec);
			if (myRec == null)
			{
				myValues.Add(valueID, new ValueRecord(valueID, value));
			}
			else
				myRec.Value = value;
		}

		/// <summary>
		/// Get a variable
		/// </summary>
		/// <param name="valueID">name of variable</param>
		/// <returns>it's value</returns>
		public static object GetValue(string valueID)
		{
			ValueRecord myRec;
			myValues.TryGetValue(valueID, out myRec);
			if (myRec == null)
			{
				return null;
			}
			else
				return myRec.Value;
		}

		/// <summary>
		/// Clear a value from list of values
		/// </summary>
		/// <param name="valueID">name of variable</param>
		/// <returns>it's value</returns>
		public bool ClearValue(string valueID)
		{
			return myValues.Remove(valueID);
		}

		#endregion


		#region STANDARD ACTIONS
		static bool initialized = false;

		//TODO add XML output
		//static bool useXML = false;

		static int level = 0;
		static int numberOfMQ = 0;
		static int numberOfEQ = 0;
		/// <summary>
		/// Totoal number of experiments on the SUL
		/// </summary>
		static int numberOfSULSteps = 0;
		/// <summary>
		/// Number of experiments performed on the system because of Equivalence query
		/// </summary>
		static int numberOfResetsForEq = 0;
		static int numberOfResets = 0;
		static int numberOfRealResets = 0;

		static TimeSpan eqTimeSpan, mqTimeSpan, rTimeSpan, qOnSULTimeSpan, totalTimeSpan;
		static DateTime eqTime, mqTime, rTime, qOnSULTime, totalTime;
		static bool eqStarted, mqStarted, rStarted, qOnSULStarted, totalStarted;

		static StringBuilder eventsLog;


		#region Logging Events

		/// <summary>
		/// Log any event
		/// </summary>
		/// <param name="ev"></param>
		public static void LogEvent(string ev)
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");

			eventsLog.AppendLine(DateTime.Now.ToString() + ": " + ev);
		}

		public static void LogString(string ev)
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");

			eventsLog.AppendLine("["+DateTime.Now.ToString() + "]: " + ev);
		}



		/// <summary>
		/// Start reseting the SUL (usually called by oracle)
		/// </summary>
		public static void LogStartSULReset()
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");

			if (level >= 1)
			{
				if (rStarted)
					throw new Exception("Previous reset is not finished yet!");
				rStarted = true;
				rTime = DateTime.Now;
			}
		}

		/// <summary>
		/// Finish reseting the SUL (usually called by oracle): after it is started
		/// </summary>
		public static void LogFinishSULReset()
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");

			if (level >= 1)
			{
				if (!rStarted)
					throw new Exception("Reset is not started yet!");
				rStarted = false;
				rTimeSpan += (DateTime.Now - rTime);
				numberOfResets++;

				if(eqStarted)
					numberOfResetsForEq++;
			}
		}

		/// <summary>
		/// Start a membership query (or output query/output tree query). It can be called by the learner right befor calling the function
		/// of the oracle
		/// <remarks>By convention, we call it in learners</remarks>
		/// </summary>
		public static void LogStartMQ()
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");
			if (level >= 1)
			{
				if (mqStarted)
					throw new Exception("Previous membership query is not finished yet!");
				mqStarted = true;
				mqTime = DateTime.Now;
			}
		}

		/// <summary>
		/// Finish a membership query (or output query/output tree query). It can be called by the learner right after calling the function
		/// of the oracle
		/// <remarks>By convention, we call it in learners</remarks>
		/// </summary>
		public static void LogFinishMQ()
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");
			if (level >= 1)
			{
				if (!mqStarted)
					throw new Exception("No membership query is started yet!");
				mqStarted = false;
				mqTimeSpan += (DateTime.Now - mqTime);
				numberOfMQ++;
			}
		}



		/// <summary>
		/// start an equivalence query. It can be called by the learner right before calling the function
		/// of the oracle
		/// <remarks>By convention, we call it in learners</remarks>
		/// </summary>
		public static void LogStartEQ()
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");
			if (level >= 1)
			{
				if (eqStarted)
					throw new Exception("Previous equivalence query is not finished yet!");
				eqStarted = true;
				eqTime = DateTime.Now;
			}
		}

		/// <summary>
		/// Finish an equivalence query. It can be called by the learner right after calling the function
		/// of the oracle
		/// <remarks>By convention, we call it in learners</remarks>
		/// </summary>
		public static void LogFinishEQ()
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");
			if (level >= 1)
			{
				if (!eqStarted)
					throw new Exception("No equivalence query is started yet!");
				eqStarted = false;
				eqTimeSpan += (DateTime.Now - eqTime);
				numberOfEQ++;
			}
		}

		public static void CancelPreviousAction()
		{
			eqStarted = mqStarted = rStarted = qOnSULStarted = totalStarted = false;
		}

		public static void CancelPreviousAction(string ac)
		{
			if (ac == "QueryOnSUL")
			{
				qOnSULStarted = false;
			}
		}

		/// <summary>
		/// Log the event of starting the learning. It is called by the learner in the begining of the main learning function.
		/// </summary>
		public static void LogStartLearning()
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");
			if (level >= 1)
			{
				if (totalStarted)
					throw new Exception("Previous learning is not finished yet!");
				totalStarted = true;
				totalTime = DateTime.Now;
			}
		}

		/// <summary>
		/// Log the event of finishing the learning. It is called by the learner in the end of the main learning function
		/// right before returning the conjecture
		/// </summary>
		public static void LogFinishLearning()
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");
			if (level >= 1)
			{
				if (!totalStarted)
					throw new Exception("No learning is started yet!");
				totalStarted = false;
				totalTimeSpan += (DateTime.Now - totalTime);
			}
		}

		/// <summary>
		/// Log the event of start asking a query step (an experiment) from SUL (it is usually called by oracle)
		/// </summary>
		public static void LogStartStepOnSUL()
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");
			if (level >= 1)
			{
				if (qOnSULStarted)
					throw new Exception("Previous step on SUL is not finished yet!");
				qOnSULStarted = true;
				qOnSULTime = DateTime.Now;
			}
		}

		/// <summary>
		/// Log the event of end asking a query step (an experiment) from SUL (it is usually called by oracle)
		/// </summary>
		public static void LogFinishStepOnSUL()
		{
			if (!initialized)
				throw new Exception("Logger is not initialized!");
			if (level >= 1)
			{
				if (!qOnSULStarted)
					throw new Exception("No step on SUL is started yet!");
				qOnSULStarted = false;
				qOnSULTimeSpan += (DateTime.Now - qOnSULTime);
				numberOfSULSteps++;
			}
		}

		/// <summary>
		/// Number of real reset (called by SUL interface)
		/// </summary>
		public static void DoRealReset()
		{
			numberOfRealResets++;
		}

		#endregion


		#region Querying log

		/// <summary>
		/// Number of actual queries performed on SUL
		/// </summary>
		public static int NumberOfSULSteps
		{
			get
			{
				return numberOfSULSteps;
			}
		}

		/// <summary>
		/// Number of Membership Queries (output queries in DFMs or output tree queries in NFMs)
		/// </summary>
		public static int NumberOfMQ
		{
			get
			{
				return numberOfMQ;
			}
		}

		/// <summary>
		/// Number of Equivalence Queries
		/// </summary>
		public static int NumberOfEQ
		{
			get
			{
				return numberOfEQ;
			}
		}

		/// <summary>
		/// Number of Resets (or experiments executed on SUL)
		/// </summary>
		public static int NumberOfResets
		{
			get
			{
				return numberOfResets;
			}
		}

		/// <summary>
		/// Time (in millisecond) which spent on total learning process
		/// </summary>
		public static double TotalLearningTime
		{
			get
			{
				return totalTimeSpan.TotalMilliseconds;
			}
		}

		/// <summary>
		/// Time (in millisecond) which spent on equivalence queries
		/// </summary>
		public static double EQTime
		{
			get
			{
				return eqTimeSpan.TotalMilliseconds;
			}
		}

		/// <summary>
		/// Time (in millisecond) which spent on membership queries
		/// </summary>
		public static double MQTime
		{
			get
			{
				return mqTimeSpan.TotalMilliseconds;
			}
		}

		/// <summary>
		/// Time (in millisecond) which spent on resets
		/// </summary>
		public static double ResetTime
		{
			get
			{
				return rTimeSpan.TotalMilliseconds;
			}
		}

		/// <summary>
		/// Time (in millisecond) which spent on SUL queries
		/// </summary>
		public static double SULQueryTime
		{
			get
			{
				return qOnSULTimeSpan.TotalMilliseconds;
			}
		}

		/// <summary>
		/// Time (in millisecond) which spent on IO (resets + queries performed on SUL)
		/// </summary>
		public static double IOTime
		{
			get
			{
				return ResetTime + SULQueryTime;
			}
		}

		/// <summary>
		/// Time (in millisecond) which spent totally in oracle (equivalence + membership). This time includes the time
		/// spent by oracle and the SUL
		/// </summary>
		public static double OracleTime
		{
			get
			{
				return EQTime + MQTime;
			}
		}
		#endregion

		#endregion


		#region -=[ IO ]=-
		//static string address;
		static StreamWriter writerStream;

		/// <summary>
		/// Print a string log
		/// </summary>
		public static void PrintLog()
		{
			Console.WriteLine(LogOfEvents());
		}

		/// <summary>
		/// This should be called just one time!
		/// </summary>
		/// <param name="address"></param>
		public static void SetOutput(string address)
		{
			//if (writerStream != null)
			//{
			//    writerStream.Close();
			//}
			//LearningLog.address = address;
			writerStream = new StreamWriter(address);
		}

		public static void FlushOutput()
		{
			if(writerStream!=null)
			{
				writerStream.Flush();
			}
			eventsLog.Clear();
		}


		public static void FinishLogging()
		{
			//writerStream.Write(LogHeader());
			//writerStream.Write(LogRow());
			if(writerStream!=null)
			{
				writerStream.Write(LogOfEvents());

				/*
				   writerStream.Write("***************\n");
				   foreach (string r in myEvents.Keys)
				   {
				    ActionRecord r2;
				    myEvents.TryGetValue(r, out r2);
				    writerStream.WriteLine(r2.ToString());
				   }
				   writerStream.Write("***************\n");
				 */
				FlushOutput();
				writerStream.Close();
			}
		}

		public static string LogHeader()
		{
			string log = "";
			//log += "---------------Learning Log-------------------\n";
			log += "Timeoflearning, " + "TimeofMQ, " + "NumberofMQ " + "TimeofEQ, " + "NumberofEQ, " +
			       "NumberofexperimentsonSUL, " + "Numberofrealresets, " + "Timespentonresets, ";

			log += "C, R, Q";
			//foreach (ValueRecord v in myValues.Values)
			//{
			//    log += v.ToString() + ",";
			//}
			log += "\n";
			//log += "----------------------------------------------\n";
			return log;
		}

		/// <summary>
		/// Return a string log
		/// </summary>
		/// <returns></returns>
		public static string LogOfEvents()
		{
			string log = "";
			log += "---------------Learning Log-------------------\n";
			log += "Time of learning (ms): " + TotalLearningTime + "\n";
			log += "Time of MQ (ms): " + MQTime + "\n";
			log += "Number of MQ: " + numberOfMQ + "\n";

			log += "Time of EQ (ms): " + EQTime + "\n";
			log += "Number of EQ: " + numberOfEQ + "\n";

			log += "Number of experiments on SUL: " + numberOfResets + (numberOfResets == 0 ? " (probabily an ideal oracle used)" : "") + "\n";

			log += "Number of experiments on SUL for Eq Queries: " + numberOfResetsForEq + "\n";
			log += "Number of real resets: " + numberOfRealResets + "\n";
			log += "Time spent on resets (ms): " + ResetTime + "\n";
			log += "----------------------------------------------\n";
			foreach (ValueRecord v in myValues.Values)
			{
				log += v.ToString() + "\n";
			}
			log += "----------------------------------------------\n";
			log += eventsLog.ToString();
			log += "----------------------------------------------\n";
			return log;
		}

		public static string LogOfEventsXML()
		{
			string log = "";
			log += "<LearningLog>\n";
			log += "<Time_of_learning unit=\"ms\">" + TotalLearningTime + "</Time_of_learning>\n";
			log += "<Time_of_MQ unit=\"ms\"> " + MQTime + "</Time_of_MQ>\n";
			log += "<Number_of_MQ>" + numberOfMQ + "</Number_of_MQ>\n";

			log += "<Time_of_EQ unit=\"(ms)\"> " + EQTime + "</Time_of_EQ>\n";
			log += "<Number_of_EQ>" + numberOfEQ + "</Number_of_EQ>\n";

			log += "Number of experiments on SUL: " + numberOfResets + (numberOfResets == 0 ? " (probabily an ideal oracle used)" : "") + "\n";

			log += "Number of experiments on SUL for Eq Queries: " + numberOfResetsForEq + "\n";
			log += "Number of real resets: " + numberOfRealResets + "\n";
			log += "Time spent on resets (ms): " + ResetTime + "\n";
			log += "----------------------------------------------\n";
			foreach (ValueRecord v in myValues.Values)
			{
				log += v.ToString() + "\n";
			}
			log += "----------------------------------------------\n";
			log += eventsLog.ToString();
			log += "----------------------------------------------\n";
			return log;
		}
		#endregion

	}
}
